from IPython.display import display, HTML
display(HTML("<style>.container {width:100% !important; }</style>"))
import glob
import pandas as pd
import numpy as np
import hvplot.pandas
import plotly.express as px
import plotly.graph_objects as go
pd.options.mode.chained_assignment = None
import datetime as dt
%autosave 30
Autosaving every 30 seconds
CPU_FREQ=2.60
rdtsc_df_dict = []
ttt_df_dict = []
for filename in glob.glob("exchange*.log") + glob.glob("*_1.log"):
print('processing {}'.format(filename))
for line in open(filename):
tokens = line.strip().split(' ')
if len(tokens) != 4:
continue
try:
time = tokens[0]
tag = tokens[2]
latency = float(tokens[3])
latency_rdtsc = latency / CPU_FREQ
time_datetime = pd.to_datetime(time, format='%H:%M:%S.%f')
except:
continue
if ' RDTSC ' in line:
if tokens[1] != 'RDTSC':
continue
rdtsc_df_dict.append({'timestamp':time, 'tag':tag, 'latency':latency_rdtsc})
elif ' TTT ' in line:
if tokens[1] != 'TTT':
continue
ttt_df_dict.append({'timestamp':time, 'tag':tag, 'latency':latency})
rdtsc_df = pd.DataFrame.from_dict(rdtsc_df_dict)
rdtsc_df = rdtsc_df.drop_duplicates().sort_values(by='timestamp')
rdtsc_df['timestamp'] = pd.to_datetime(rdtsc_df['timestamp'], format='%H:%M:%S.%f')
ttt_df = pd.DataFrame.from_dict(ttt_df_dict)
ttt_df = ttt_df.drop_duplicates().sort_values(by='timestamp')
ttt_df['timestamp'] = pd.to_datetime(ttt_df['timestamp'], format='%H:%M:%S.%f')
processing exchange_snapshot_synthesizer.log processing exchange_order_server.log processing exchange_main.log processing exchange_matching_engine.log processing exchange_market_data_publisher.log processing trading_main_1.log processing trading_order_gateway_1.log processing trading_engine_1.log processing trading_market_data_consumer_1.log
for tag in rdtsc_df['tag'].unique():
print(tag)
fig = go.Figure()
t_df = rdtsc_df[rdtsc_df['tag'] == tag].copy()
t_df = t_df[t_df['latency'] > 0]
q_hi = t_df['latency'].quantile(0.99)
q_lo = t_df['latency'].quantile(0.01)
t_df = t_df[(t_df['latency'] < q_hi) & (t_df['latency'] > q_lo)]
mean = t_df['latency'].astype(float).mean()
print('{} has {} observations mean {}'.format(tag, len(t_df), mean))
rolling_window = max(1, int(len(t_df) / 100))
use_micros = False
if mean >= 1000:
use_micros = True
t_df['latency'] = t_df['latency'].astype(float) / 1000
fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'], name=tag))
fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'].rolling(rolling_window).mean(), name=tag + ' mean'))
# fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency'].rolling(rolling_window).std(), name=tag + ' std'))
fig.update_layout(title='performance ' + tag + ' ' + ('microseconds' if use_micros else 'nanoseconds'), height=700, hovermode='x')
fig.show()
Exchange_FIFOSequencer_addClientRequest Exchange_FIFOSequencer_addClientRequest has 10487 observations mean 82.03394679126538
Exchange_FIFOSequencer_sequenceAndPublish Exchange_FIFOSequencer_sequenceAndPublish has 10374 observations mean 53909.935971585764
Exchange_MEOrderBook_checkForMatch Exchange_MEOrderBook_checkForMatch has 5703 observations mean 163383.84224227464
Exchange_MEOrderBook_addOrder Exchange_MEOrderBook_addOrder has 3636 observations mean 497.1089320470508
Exchange_MEOrderBook_add Exchange_MEOrderBook_add has 5708 observations mean 337468.20750902913
Exchange_MatchingEngine_processClientRequest Exchange_MatchingEngine_processClientRequest has 11326 observations mean 254875.95264130185
Exchange_MEOrderBook_removeOrder Exchange_MEOrderBook_removeOrder has 2969 observations mean 1281.9594787159622
Exchange_MEOrderBook_cancel Exchange_MEOrderBook_cancel has 5616 observations mean 56774.474989042305
Exchange_McastSocket_send Exchange_McastSocket_send has 12158 observations mean 433.9329279866374
Exchange_TCPSocket_send Exchange_TCPSocket_send has 18355 observations mean 185.35437839197033
Trading_MarketDataConsumer_recvCallback Trading_MarketDataConsumer_recvCallback has 6389 observations mean 177245.91413125925
Trading_MarketOrderBook_addOrder Trading_MarketOrderBook_addOrder has 3392 observations mean 427.95378265602324
Trading_MarketOrderBook_updateBBO Trading_MarketOrderBook_updateBBO has 8566 observations mean 128.4547136263223
Trading_PositionKeeper_updateBBO Trading_PositionKeeper_updateBBO has 8642 observations mean 8776.86695565485
Trading_FeatureEngine_onOrderBookUpdate Trading_FeatureEngine_onOrderBookUpdate has 8647 observations mean 14266.052477070749
Trading_TradeEngine_algoOnOrderBookUpdate_ Trading_TradeEngine_algoOnOrderBookUpdate_ has 8647 observations mean 109645.07356931259
Trading_MarketOrderBook_removeOrder Trading_MarketOrderBook_removeOrder has 2969 observations mean 1169.0306241417727
Exchange_MEOrderBook_match Exchange_MEOrderBook_match has 3548 observations mean 271042.8621758737
Trading_FeatureEngine_onTradeUpdate Trading_FeatureEngine_onTradeUpdate has 3547 observations mean 20618.933334779118
Trading_TradeEngine_algoOnTradeUpdate_ Trading_TradeEngine_algoOnTradeUpdate_ has 3548 observations mean 18355.942134246812
Trading_RiskManager_checkPreTradeRisk Trading_RiskManager_checkPreTradeRisk has 2964 observations mean 126.83406000207619
Trading_OrderManager_newOrder Trading_OrderManager_newOrder has 808 observations mean 89585.44411652703
Trading_OrderManager_moveOrder Trading_OrderManager_moveOrder has 16868 observations mean 8806.37730066945
Trading_OrderManager_moveOrders Trading_OrderManager_moveOrders has 8437 observations mean 47130.119346103704
Trading_TCPSocket_send Trading_TCPSocket_send has 1521 observations mean 297.0525464016588
Trading_OrderGateway_recvCallback Trading_OrderGateway_recvCallback has 2083 observations mean 86485.13072860887
Trading_OrderManager_onOrderUpdate Trading_OrderManager_onOrderUpdate has 2361 observations mean 42613.87270713192
Trading_TradeEngine_algoOnOrderUpdate_ Trading_TradeEngine_algoOnOrderUpdate_ has 2361 observations mean 81860.59182875573
Trading_PositionKeeper_addFill Trading_PositionKeeper_addFill has 835 observations mean 45744.09120221096
Trading_OrderManager_cancelOrder Trading_OrderManager_cancelOrder has 716 observations mean 132393.5270734852
HOPS = [
['T1_OrderServer_TCP_read', 'T2_OrderServer_LFQueue_write'],
['T2_OrderServer_LFQueue_write', 'T3_MatchingEngine_LFQueue_read'],
['T3_MatchingEngine_LFQueue_read', 'T4_MatchingEngine_LFQueue_write'], ['T3_MatchingEngine_LFQueue_read', 'T4t_MatchingEngine_LFQueue_write'],
['T4_MatchingEngine_LFQueue_write', 'T5_MarketDataPublisher_LFQueue_read'], ['T4t_MatchingEngine_LFQueue_write', 'T5t_OrderServer_LFQueue_read'],
['T5_MarketDataPublisher_LFQueue_read', 'T6_MarketDataPublisher_UDP_write'], ['T5t_OrderServer_LFQueue_read', 'T6t_OrderServer_TCP_write'],
['T7_MarketDataConsumer_UDP_read', 'T8_MarketDataConsumer_LFQueue_write'], ['T7t_OrderGateway_TCP_read', 'T8t_OrderGateway_LFQueue_write'],
['T8_MarketDataConsumer_LFQueue_write', 'T9_TradeEngine_LFQueue_read'], ['T8t_OrderGateway_LFQueue_write', 'T9t_TradeEngine_LFQueue_read'],
['T9_TradeEngine_LFQueue_read', 'T10_TradeEngine_LFQueue_write'], ['T9t_TradeEngine_LFQueue_read', 'T10_TradeEngine_LFQueue_write'],
['T10_TradeEngine_LFQueue_write', 'T11_OrderGateway_LFQueue_read'],
['T11_OrderGateway_LFQueue_read', 'T12_OrderGateway_TCP_write'],
# exchange <-> client
['T12_OrderGateway_TCP_write', 'T1_OrderServer_TCP_read'],
['T6_MarketDataPublisher_UDP_write', 'T7_MarketDataConsumer_UDP_read'], ['T6t_OrderServer_TCP_write', 'T7t_OrderGateway_TCP_read'],
]
for tags in HOPS:
tag_p, tag_n = tags
print('{} => {}. {} => {}.'.format(tag_p, len(ttt_df[ttt_df['tag'] == tag_p]), tag_n, len(ttt_df[ttt_df['tag'] == tag_n])))
fig = go.Figure()
t_df = ttt_df[(ttt_df['tag'] == tag_n) | (ttt_df['tag'] == tag_p)]
t_df['latency_diff'] = t_df['latency'].diff()
t_df = t_df[t_df['latency_diff'] > 0]
t_df = t_df[t_df.tag == tag_n]
q_hi = t_df['latency_diff'].quantile(0.99)
q_lo = t_df['latency_diff'].quantile(0.01)
t_df = t_df[(t_df['latency_diff'] < q_hi) & (t_df['latency_diff'] > q_lo)]
mean = t_df['latency_diff'].astype(float).mean()
print('{} has {} observations mean {}'.format(tag_n, len(t_df), mean))
rolling_window = max(1, int(len(t_df) / 100))
unit = 'nanoseconds'
if mean >= 1000000:
unit = 'milliseconds'
t_df['latency_diff'] = t_df['latency_diff'].astype(float) / 1000000
elif mean >= 1000:
unit = 'microseconds'
t_df['latency_diff'] = t_df['latency_diff'].astype(float) / 1000
tag_name = tag_p + ' -> ' + tag_n
fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency_diff'], name=tag_name))
fig.add_trace(go.Scatter(x=t_df['timestamp'], y=t_df['latency_diff'].rolling(rolling_window).mean(), name=tag_name + ' mean'))
fig.update_layout(title='performance ' + tag_name + ' ' + unit, height=700, hovermode='x')
fig.show()
T1_OrderServer_TCP_read => 10870. T2_OrderServer_LFQueue_write => 11558. T2_OrderServer_LFQueue_write has 11306 observations mean 131404.89509994694
T2_OrderServer_LFQueue_write => 11558. T3_MatchingEngine_LFQueue_read => 11558. T3_MatchingEngine_LFQueue_read has 10784 observations mean 3189226.278931751
T3_MatchingEngine_LFQueue_read => 11558. T4_MatchingEngine_LFQueue_write => 12447. T4_MatchingEngine_LFQueue_write has 12175 observations mean 344765.1561396304
T3_MatchingEngine_LFQueue_read => 11558. T4t_MatchingEngine_LFQueue_write => 18802. T4t_MatchingEngine_LFQueue_write has 18406 observations mean 259917.150494404
T4_MatchingEngine_LFQueue_write => 12447. T5_MarketDataPublisher_LFQueue_read => 12447. T5_MarketDataPublisher_LFQueue_read has 12066 observations mean 1910351.753356539
T4t_MatchingEngine_LFQueue_write => 18802. T5t_OrderServer_LFQueue_read => 18802. T5t_OrderServer_LFQueue_read has 18290 observations mean 1908845.1604155276
T5_MarketDataPublisher_LFQueue_read => 12447. T6_MarketDataPublisher_UDP_write => 12447. T6_MarketDataPublisher_UDP_write has 12188 observations mean 317922.17394158186
T5t_OrderServer_LFQueue_read => 18802. T6t_OrderServer_TCP_write => 18802. T6t_OrderServer_TCP_write has 18342 observations mean 273255.22625667864
T7_MarketDataConsumer_UDP_read => 6521. T8_MarketDataConsumer_LFQueue_write => 12447. T8_MarketDataConsumer_LFQueue_write has 12186 observations mean 79705.87099950764
T7t_OrderGateway_TCP_read => 2127. T8t_OrderGateway_LFQueue_write => 2411. T8t_OrderGateway_LFQueue_write has 2359 observations mean 65511.90843577787
T8_MarketDataConsumer_LFQueue_write => 12447. T9_TradeEngine_LFQueue_read => 12447. T9_TradeEngine_LFQueue_read has 11881 observations mean 2050386.8482450973
T8t_OrderGateway_LFQueue_write => 2411. T9t_TradeEngine_LFQueue_read => 2411. T9t_TradeEngine_LFQueue_read has 2269 observations mean 3638119.7990304097
T9_TradeEngine_LFQueue_read => 12447. T10_TradeEngine_LFQueue_write => 1558. T10_TradeEngine_LFQueue_write has 1526 observations mean 482122.48492791614
T9t_TradeEngine_LFQueue_read => 2411. T10_TradeEngine_LFQueue_write => 1558. T10_TradeEngine_LFQueue_write has 1525 observations mean 53165673.421639346
T10_TradeEngine_LFQueue_write => 1558. T11_OrderGateway_LFQueue_read => 1558. T11_OrderGateway_LFQueue_read has 1512 observations mean 3256479.8306878307
T11_OrderGateway_LFQueue_read => 1558. T12_OrderGateway_TCP_write => 1558. T12_OrderGateway_TCP_write has 1525 observations mean 543867.3836065574
T12_OrderGateway_TCP_write => 1558. T1_OrderServer_TCP_read => 10870. T1_OrderServer_TCP_read has 10650 observations mean 17094756.1885446
T6_MarketDataPublisher_UDP_write => 12447. T7_MarketDataConsumer_UDP_read => 6521. T7_MarketDataConsumer_UDP_read has 6389 observations mean 2657020.393801847
T6t_OrderServer_TCP_write => 18802. T7t_OrderGateway_TCP_read => 2127. T7t_OrderGateway_TCP_read has 2083 observations mean 2816762.8382141143
import session_info
session_info.show()
----- hvplot 0.8.3 numpy 1.24.3 pandas 2.0.1 plotly 5.14.1 session_info 1.0.0 -----
PIL 9.0.1 apport_python_hook NA arrow 1.2.3 asttokens NA attr 23.1.0 backcall 0.2.0 bleach 6.0.0 bokeh 3.1.1 bs4 4.12.2 cffi 1.15.1 chardet 4.0.0 colorama 0.4.4 colorcet 3.0.1 comm 0.1.3 cython_runtime NA dateutil 2.8.2 debugpy 1.6.7 decorator 5.1.1 defusedxml 0.7.1 executing 1.2.0 fastjsonschema NA fqdn NA google NA holoviews 1.16.0 idna 3.3 ipykernel 6.23.1 ipython_genutils 0.2.0 isoduration NA jedi 0.18.2 jinja2 3.1.2 jsonpointer 2.3 jsonschema 4.17.3 jupyterlab_pygments 0.2.2 markupsafe 2.0.1 mistune 2.0.5 nbclient 0.8.0 nbconvert 7.4.0 nbformat 5.8.0 netifaces 0.11.0 packaging 23.1 pandocfilters NA panel 1.0.2 param 1.13.0 parso 0.8.3 pexpect 4.8.0 pickleshare 0.7.5 pkg_resources NA platformdirs 3.5.1 prompt_toolkit 3.0.38 psutil 5.9.5 ptyprocess 0.7.0 pure_eval 0.2.2 pydev_ipython NA pydevconsole NA pydevd 2.9.5 pydevd_file_utils NA pydevd_plugins NA pydevd_tracing NA pygments 2.15.1 pyparsing 2.4.7 pyrsistent NA pytz 2022.1 pyviz_comms 2.2.1 rfc3339_validator 0.1.4 rfc3986_validator 0.1.1 sitecustomize NA six 1.16.0 soupsieve 2.4.1 stack_data 0.6.2 tenacity NA tinycss2 1.2.1 tornado 6.3.2 tqdm 4.65.0 traitlets 5.9.0 tzdata 2023.3 uri_template NA wcwidth 0.2.6 webcolors 1.13 webencodings 0.5.1 xyzservices 2023.5.0 yaml 5.4.1 zmq 25.0.2 zoneinfo NA
----- IPython 8.13.2 jupyter_client 8.2.0 jupyter_core 5.3.0 notebook 6.5.4 ----- Python 3.10.6 (main, May 29 2023, 11:10:38) [GCC 11.3.0] Linux-5.19.0-43-generic-x86_64-with-glibc2.35 ----- Session information updated at 2023-06-07 15:37